Skip to content

Conversation

@alexsku
Copy link
Owner

@alexsku alexsku commented Dec 23, 2016

I think there is an issue in current MiniProfiler V4 when the profiler is used with async code. The issue is caused by lack of thread synchronization when creating instances of Timing.

This PR demonstrates this issue. It adds a test action that is async. Internally the action makes multiple calls to a service (FooService), the calls are done in parallel and then awaited all together. The invoked service methods (FooAsync) are performing async operations sequentially and measure times for them.

Because the executions of FooAsync are awaited together (using Task.WhenAll) and because FooAsync is using ConfigureAwait(false) internally the continuations in FooAsync will execute in parallel and the Timing.Children list will be accessed from multiple threads concurrently.

When the concurrency issue reproduces CallAsync should throw an exception which will be reported by the web page as ERROR


class FooService
{
public async Task FooAsync(MiniProfiler profiler)
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the method simulates a typical service method. Following typical pattern the service implementation is using ConfigureAwait(false).

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why are we passing the profiler into the service? I don't think this is a standard practice. I think it's better if the service just uses Miniprofiler.Current.

public async Task FooAsync(MiniProfiler profiler)
{
await Task.Delay(10).ConfigureAwait(false);
using (profiler.Step("foo async"))
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

MVC sample is using WebRequestProfilerProvider which relies on HttpContext to carry the miniprofiler instance. Since this is a continuation after ConfigureAwait(false) the synchronization context together with the HttpContext will be removed here. So if I don't use an explicit reference to profiler here the step would not be recorded at all.

DefaultProfilerProvider (and its possible future merge with WebRequestProfilerProvider) would fix this issue by using AsyncLocal to carry the mini profiler instance.

However the execution of the continuation is not synchronized with continuations from other 9 calls to FooAsync that are made from the same CallAsync call (and they all share the same instance of MiniProfiler). As a result Timing.AddChild might be invoked concurrently.

This is the exact problem that i'm trying to prevent.

if (Interlocked.Increment(ref _threadsAccessing) > 1)
throw new Exception("Concurrent access");

Task.Delay(10).Wait();
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is an artificial delay added to increase the chance of concurrency

Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thread.Sleep I guess is not available in .netcore (or perhaps i need to install a separate package).

/// <returns>The <see cref="ActionResult"/>.</returns>
public ActionResult ResultsAuthorization() => View();

public async Task<ActionResult> CallAsync()
Copy link
Owner Author

@alexsku alexsku Dec 24, 2016

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this action simulates a typical async action that invokes an async service method (FooAsync). The service method might access some data sources (like redis, database etc) and measure the performance of individual calls.

The action also invokes multiple service calls and waits for completion all of them. This is also quite legitimate pattern, which parallelizes execution of the service methods to increase the action's response time

{
if (Children == null)
if (Interlocked.Increment(ref _threadsAccessing) > 1)
throw new Exception("Concurrent access");
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this throws with almost every request to CallAsync


class FooService
{
public async Task FooAsync(MiniProfiler profiler)
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

why are we passing the profiler into the service? I don't think this is a standard practice. I think it's better if the service just uses Miniprofiler.Current.

{
public async Task FooAsync()
{
var profiler = MiniProfiler.Current;
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

MVC sample is using WebRequestProfilerProvider which relies on HttpContext to carry the miniprofiler instance. Since this is a continuation after ConfigureAwait(false) the synchronization context together with the HttpContext will be removed here. So if I don't use an explicit reference to profiler here the step would not be recorded at all.

DefaultProfilerProvider (and its possible future merge with WebRequestProfilerProvider) would fix this issue by using AsyncLocal to carry the mini profiler instance.

However the execution of the continuation is not synchronized with continuations from other 9 calls to FooAsync that are made from the same CallAsync call (and they all share the same instance of MiniProfiler). As a result Timing.AddChild might be invoked concurrently.

This is the exact problem that i'm trying to prevent.


class FooService
{
public async Task FooAsync()
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the method simulates a typical service method. Following typical pattern the service implementation is using ConfigureAwait(false).

public async Task FooAsync()
{
var profiler = MiniProfiler.Current;
await Task.Delay(10).ConfigureAwait(false);
Copy link
Owner Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

continuations of this await will execute in parallel since await is using ConfigureAwait(false) and the calling method is using Task.WhenAll instead of awaiting individual executions.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants